TimDaub
commented
1 year ago 2023-11-03T10:41:44: 2023-11-03T10:41:44.271Z @attestate/delegator2 Existing delegation for the "to" address: 0x03E16AF2f65Ac64054Dfb5480F7BE9B596ADC362 2023-11-03T10:41:44: 2023-11-03T10:41:44.470Z @attestate/kiwistand Before storage, has checkpoints false 2023-11-03T10:41:44: 2023-11-03T10:41:44.470Z @attestate/kiwistand Attempting to store message with index "6544ce67cf53de8adeb28af888c32f49766efee85cf7c05f70cb3dada3d9e239bf344baf" and message: "y^A@{"href":"https://www.thefp.com/p/humiliating-cross-examination-sam-bankman-fried","signature":"0xbfc49437dabeb0c8558c8de671357d4c04b76ddc8e8b17a2c50f8a8d44db1db24e366f95a0b1b7734790baa76336309f4452edf55863074e0650fe22b35fdd241b","timestamp":1699008103,"title":"The Humiliating Cross-Examination of SBF","type":"amplify"}" 2023-11-03T10:41:44: 2023-11-03T10:41:44.682Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-03T10:41:44: 2023-11-03T10:41:44.698Z @attestate/delegator2 Invalid delegation: "Recovered address and claimed address aren't equal" 2023-11-03T10:41:44: 2023-11-03T10:41:44.701Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-03T10:41:44: 2023-11-03T10:41:44.818Z @attestate/delegator2 Existing delegation for the "to" address: 0x03E16AF2f65Ac64054Dfb5480F7BE9B596ADC362 2023-11-03T10:41:45: 2023-11-03T10:41:45.010Z @attestate/kiwistand leaves: Does trie have check points? "false" 2023-11-03T10:41:45: 2023-11-03T10:41:45.010Z @attestate/kiwistand leaves: Trie root "c34898fae 70c246d243d5aa24f831a983c843c9651bd3178bb16fa6327ad887e" 2023-11-03T10:41:45: /root/kiwistand/node_modules/@ethereumjs/trie/dist/trie/trie.js:309 2023-11-03T10:41:45: throw new Error('Missing node in DB'); 2023-11-03T10:41:45: ^ 2023-11-03T10:41:45: 2023-11-03T10:41:45: Error: Missing node in DB 2023-11-03T10:41:45: at Trie.lookupNode (/root/kiwistand/node_modules/@ethereumjs/trie/dist 2023-11-03T10:41:45: at async leaves (file:///root/kiwistand/src/store.mjs:426:25) 2023-11-03T10:41:45: at async Module.posts (file:///root/kiwistand/src/store.mjs:395:17) 2023-11-03T10:41:45: at async index (file:///root/kiwistand/src/views/feed.mjs:159:16) 2023-11-03T10:41:45: at async default (file:///root/kiwistand/src/views/feed.mjs:284:51) 2023-11-03T10:41:45: at async file:///root/kiwistand/src/http.mjs:130:21
Basically we manage to store the message until here: https://github.com/attestate/kiwistand/blob/cef37444af0a4f639a71a57c0fe37d126238841c/src/store.mjs#L298
and then interestingly the logs after trie.put never get logged. Instead the stack trace indicates that someone loaded the / page in parallel and the feed.mjs crashed trying to find the root node. So to me that now looks like some kind of parallelism issue
2023-11-02T09:48:04: 2023-11-02T09:48:04.462Z @attestate/delegator2 Existing delegation for the "to" address: 0x03E16AF2f65Ac64054Dfb5480F7BE9B596ADC362 2023-11-02T09:48:04: /root/kiwistand/node_modules/@ethereumjs/trie/dist/trie/trie.js:309 2023-11-02T09:48:04: throw new Error('Missing node in DB'); 2023-11-02T09:48:04: ^ 2023-11-02T09:48:04: 2023-11-02T09:48:04: Error: Missing node in DB 2023-11-02T09:48:04: at Trie.lookupNode (/root/kiwistand/node_modules/@ethereumjs/trie/dist /trie/trie.js:309:19) 2023-11-02T09:48:04: at async walkTrieDfs (file:///root/kiwistand/src/store.mjs:463:16) 2023-11-02T09:48:04: at async leaves (file:///root/kiwistand/src/store.mjs:420:25) 2023-11-02T09:48:04: at async Module.posts (file:///root/kiwistand/src/store.mjs:391:17) 2023-11-02T09:48:04: at async default (file:///root/kiwistand/src/views/upvotes.mjs:49:16) 2023-11-02T09:48:04: at async getProfile (file:///root/kiwistand/src/http.mjs:369:21) 2023-11-02T09:48:04: at async file:///root/kiwistand/src/http.mjs:423:21 2023-11-02T09:48:04: 2023-11-02T09:48:04: Node.js v19.9.0 2023-11-02T09:48:06: 2023-11-02T09:48:06.930Z @attestate/kiwistand Launching as bootstrap node 2023-11-02T09:48:06: 2023-11-02T09:48:06.931Z @attestate/kiwistand Using id from disk.
few observations
Logs indicate that the trie was "walked" at the same time
2023-11-02T09:47:51: 2023-11-02T09:47:51.207Z @attestate/crawler:lifecycle Waiting "60000ms" to repeat the task 2023-11-02T09:48:03: 2023-11-02T09:48:03.614Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-02T09:48:03: 2023-11-02T09:48:03.635Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-02T09:48:03: 2023-11-02T09:48:03.638Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-02T09:48:03: 2023-11-02T09:48:03.780Z @attestate/delegator2 Existing delegation for the "to" address: 0x03E16AF2f65Ac64054Dfb5480F7BE9B596ADC362 2023-11-02T09:48:04: 2023-11-02T09:48:04.294Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-02T09:48:04: 2023-11-02T09:48:04.316Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-02T09:48:04: 2023-11-02T09:48:04.319Z @attestate/delegator2 Invalid delegation: "Recove red address and claimed address aren't equal" 2023-11-02T09:48:04: 2023-11-02T09:48:04.462Z @attestate/delegator2 Existing delegation for the "to" address: 0x03E16AF2f65Ac64054Dfb5480F7BE9B596ADC362 2023-11-02T09:48:04: /root/kiwistand/node_modules/@ethereumjs/trie/dist/trie/trie.js:309 2023-11-02T09:48:04: throw new Error('Missing node in DB'); 2023-11-02T09:48:04: ^ 2023-11-02T09:48:04: 2023-11-02T09:48:04: Error: Missing node in DB 2023-11-02T09:48:04: at Trie.lookupNode (/root/kiwistand/node_modules/@ethereumjs/trie/dist /trie/trie.js:309:19)
which makes sense, but could potentially indicate that there was some faulty parallelism between accessing data in the trie and e.g. writing.